Flexにもログを #1

#RIA

#Adobe Flex

かけがわ

2011.10.13

この記事は公開されてから1年以上経過しています。情報が古い可能性がありますので、ご注意ください。

障害や意図しない挙動などの原因がどこにあるか分からず、追跡に大きく時間を割かれてしまう・・・Flex開発をしているとそんなことがたびたびあるのではないかと思います。そんなとき、アプリケーションの動作状況をチェックできるログがあれば、原因となる箇所の目星をつけやすくなり、改修にかかる時間が短縮できますよね。また、デバッグ実行できない環境下でも大いに役立つはずです。

といっても、自前でログ出力の仕組みを用意しようとするとそれなりに手間がかかってしまいます。しかし幸いなことに、Flexにはとても簡単にログを出力するための仕組みが提供されています。

この記事では、Flex標準のログAPIを一から再確認していきたいと思います。普段Flexを使ってお仕事をされている方でも、「え？Flexにログを出す仕組みなんてあったっけ？」っていう方がいるんじゃないかと思いますので、特にそんな方に読んでいただければと思います。

ログAPIの仕組み

FlexのログAPIは出力命令と出力処理を担うコンポーネントが分かれています。出力命令を担うコンポーネントが「出力する内容」を決定し、出力処理を担うコンポーネントが「出力先」を決定します。これらの関係についてはflex:mx.logging機能についてで分かりやすく解説されているのでこちらを参考にされるといいと思います。

ログ出力処理手順

ログ出力までの手順としては、以下のような流れになります。

出力処理オブジェクトの生成
出力処理オブジェクトに出力時の条件を設定
出力処理オブジェクトを出力先として登録
出力命令オブジェクトを取得して出力命令実行

手順１から３までは最初に１回済ませてしまえば基本的には何度も行う必要はありません。

以下は、実際にログを出力するサンプルのソースコードです。(FlexSDK 4.5.1.21328で動作確認)

<?xml version="1.0" encoding="utf-8"?>
<s:Application xmlns:fx="http://ns.adobe.com/mxml/2009" 
               xmlns:s="library://ns.adobe.com/flex/spark" 
               xmlns:mx="library://ns.adobe.com/flex/mx"
               preinitialize="application1_preinitializeHandler(event)"
               initialize="application1_initializeHandler(event)"
               creationComplete="application1_creationCompleteHandler(event)"
               applicationComplete="application1_applicationCompleteHandler(event)">
    <fx:Script>
        <![CDATA[
            import mx.events.FlexEvent;
            import mx.logging.ILogger;
            import mx.logging.Log;
            import mx.logging.LogEventLevel;
            import mx.logging.targets.TraceTarget;
            
            private var logger:ILogger = Log.getLogger("LoggerTest");
            
            private function initializeLogger():void 
            {
                var traceTarget:TraceTarget = new TraceTarget();
                traceTarget.level = LogEventLevel.ALL;
                traceTarget.filters = ["*"];
                traceTarget.includeDate = true;
                traceTarget.includeTime = true;
                traceTarget.includeLevel = true;
                traceTarget.includeCategory = true;
                Log.addTarget(traceTarget);
            }

            protected function application1_preinitializeHandler(event:FlexEvent):void
            {
                initializeLogger();
                logger.debug("preinitialize");
            }

            protected function application1_initializeHandler(event:FlexEvent):void
            {
                logger.info("initialize");
            }

            protected function application1_creationCompleteHandler(event:FlexEvent):void
            {
                logger.warn("creationComplete");
            }

            protected function application1_applicationCompleteHandler(event:FlexEvent):void
            {
                logger.error("applicationComplete");
            }

        ]]>
    </fx:Script>
</s:Application>

このサンプルでは、preinitializeイベントのイベントハンドラ内でロガーの準備をして、ビジュアルコンポーネントの各生成段階イベントのイベントハンドラ内で適当なレベルのログを出力しています。

以下はサンプルの実行結果です。日付・時間・ログレベル・カテゴリ・メッセージがフォーマットされて出力されているのが確認できます。

実行結果

それでは、ログ出力までの手順と比べながらサンプルのソースコードを追っていきましょう。

出力処理オブジェクトの生成

手順１の出力処理オブジェクトの生成部分です。

var traceTarget:TraceTarget = new TraceTarget();

出力処理オブジェクト（ILoggingTarget実装）の生成を行っています。TraceTargetは、出力命令を受け取ると標準出力にログを出力する出力処理オブジェクトです。出力処理オブジェクトの実装を変えることによって、ログの出力先を変更することができます。

出力処理オブジェクトに出力時の条件を設定

ここからは、手順２の出力処理オブジェクトに出力時の条件を設定する処理を見ていきます。

まずは、ログレベルの設定です。

traceTarget.level = LogEventLevel.ALL;

TraceTargetのlevelプロパティは、出力するログのレベルの範囲を決定します。levelプロパティで設定されたレベル以上のログが出力されるようになります。

ログレベルは、以下のように分かれています。

FATAL
ERROR
WARNING
INFO
DEBUG

上にあるものほどレベルが高く、基本的にはアプリケーションの動作への影響度が大きいことを表します。サンプルではLogEventLevel.ALLが設定されていますので、すべてのログが出力されることになります。

次に、フィルタの設定です。

traceTarget.filters = ["*"];

filtersプロパティは出力するログのカテゴリを絞り込みます。通常カテゴリは、ログ出力処理が記述されているクラスの完全修飾名を指定します。その上で、ログを出力したいコンポーネントのパッケージをfiltersに指定すると、指定されたパッケージのログのみを出すことができます。

例えば、FlexのRPCコンポーネントのログのみを出力したい場合は

traceTarget.filters = ["mx.rpc.*"];

とします。

また、以下のように複数指定することもできます。

traceTarget.filters = ["mx.rpc.*","mx.messaging.*"];

サンプルでは、ワイルドカードが指定されているので、すべてのカテゴリが出力されることになります。なお、あまり細かいフィルタをかける必要がないのであれば、カテゴリを完全修飾名にせず、主要なコンポーネントごとに大まかなカテゴリ名をつけてもいいかもしれません。

最後に、付加情報の設定です。

traceTarget.includeDate = true;
traceTarget.includeTime = true;
traceTarget.includeLevel = true;
traceTarget.includeCategory = true;

includeDateプロパティは日付、includeTimeプロパティは時間、includeLevelプロパティはログレベル、includeCategoryプロパティはカテゴリを、出力するログの内容に含めるかを設定します。ここでtrueに設定された項目が、出力命令時に指定するメッセージに付加されて、最終的にログとして出力されることになります。

出力処理オブジェクトを出力先として登録

手順３の出力処理オブジェクトを出力先として登録する処理を見てみましょう。

Log.addTarget(traceTarget);

ここで出てくるLogクラスは直接ログ出力処理は行いませんが、出力命令オブジェクトと出力処理オブジェクトを管理して紐付ける役割を担っています。addTargetは、出力命令があった際に呼び出す出力処理を追加するための静的メソッドです。出力処理は複数追加可能で、出力命令があると追加された出力処理が全て実行されます。

また、addTargetで追加した出力処理オブジェクトを削除するremoveTargetという静的メソッドも用意されています。特定の出力先の出力処理を止めたい場合は、このremoveTargetを使用するかそもそも出力処理オブジェクトを追加しないかになります。

サンプルでは、traceTargetが引数に取られているので、出力命令があった際には標準出力にログが出力されることになります。

出力命令オブジェクトを取得して出力命令実行

最後に、手順４の出力命令実行処理を見ます。

private var logger:ILogger = Log.getLogger("LoggerTest");

Logクラスの静的メソッドgetLoggerを使って出力命令オブジェクト（ILogger実装）を取得しています。出力命令オブジェクトを取得する際に、getLoggerの引数でカテゴリを指定します。

logger.debug("preinitialize");

取得された出力命令オブジェクトのdebugメソッドを使って、ログレベルが"DEBUG"のログの出力命令を実行しています。出力命令オブジェクトにはログレベルごとに出力命令メソッドが用意されています。サンプルでは、呼び出したメソッドに応じたログレベルが出力されたログに表示されていることが確認できると思います。

なお、サンプルではLog.getLoggerがLog.addTargetより先に実行されますが、どちらを先に実行しても問題ありません。